Closed Bug 1641872 Opened 5 years ago Closed 2 years ago

Intermittent remote/cdp/test/browser/network/browser_navigationEvents.js | Received expected number of events - Got X, expected Y

Categories

(Remote Protocol :: CDP, defect, P5)

x86_64
Linux
defect

Tracking

(firefox110 wontfix, firefox111 fixed)

RESOLVED FIXED
111 Branch
Tracking Status
firefox110 --- wontfix
firefox111 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: whimboo)

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure)

Filed by: btara [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=304262938&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/SNz75jiJT1-oMimZioCbIQ/runs/0/artifacts/public/logs/live_backing.log


[task 2020-05-29T13:34:42.785Z] 13:34:42     INFO - TEST-START | remote/test/browser/network/browser_navigationEvents.js
[task 2020-05-29T13:34:42.802Z] 13:34:42     INFO - GECKO(4130) | [Parent 4130: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f019f838000 == 16 [pid = 4130] [id = {845b63a2-1ef0-4fed-96f7-7ee46befceb7}]
[task 2020-05-29T13:34:42.802Z] 13:34:42     INFO - GECKO(4130) | [Parent 4130: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 79 (0x7f01a2ba3650) [pid = 4130] [serial = 126] [outer = (nil)]
[task 2020-05-29T13:34:42.802Z] 13:34:42     INFO - GECKO(4130) | [Parent 4130: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 80 (0x7f019f842800) [pid = 4130] [serial = 127] [outer = 0x7f01a2ba3650]
[task 2020-05-29T13:34:42.810Z] 13:34:42     INFO - GECKO(4130) | [Parent 4130: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 81 (0x7f01a0228000) [pid = 4130] [serial = 128] [outer = 0x7f01a2ba3650]
[task 2020-05-29T13:34:43.048Z] 13:34:43     INFO - GECKO(4130) | [Parent 4130, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, nullptr) failed with result 0x804B000A (NS_ERROR_MALFORMED_URI): file /builds/worker/checkouts/gecko/extensions/permissions/Permission.cpp, line 46
[task 2020-05-29T13:34:43.048Z] 13:34:43     INFO - GECKO(4130) | [Parent 4130, Main Thread] WARNING: NS_ENSURE_TRUE(principal) failed: file /builds/worker/checkouts/gecko/extensions/permissions/Permission.cpp, line 58
[task 2020-05-29T13:34:43.048Z] 13:34:43     INFO - GECKO(4130) | [Parent 4130, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, nullptr) failed with result 0x804B000A (NS_ERROR_MALFORMED_URI): file /builds/worker/checkouts/gecko/extensions/permissions/Permission.cpp, line 46
[task 2020-05-29T13:34:43.048Z] 13:34:43     INFO - GECKO(4130) | [Parent 4130, Main Thread] WARNING: NS_ENSURE_TRUE(principal) failed: file /builds/worker/checkouts/gecko/extensions/permissions/Permission.cpp, line 58
[task 2020-05-29T13:34:43.064Z] 13:34:43     INFO - GECKO(4130) | [Child 4472: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7fadfc8c8000 == 1 [pid = 4472] [id = {a4e9ec03-132d-4252-a03c-4cd9c517fa34}]
[task 2020-05-29T13:34:43.065Z] 13:34:43     INFO - GECKO(4130) | [Child 4472: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x7fae17c93180) [pid = 4472] [serial = 12] [outer = (nil)]
[task 2020-05-29T13:34:43.065Z] 13:34:43     INFO - GECKO(4130) | [Child 4472: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7fadfc8ca400) [pid = 4472] [serial = 13] [outer = 0x7fae17c93180]
[task 2020-05-29T13:34:43.105Z] 13:34:43     INFO - GECKO(4130) | [Child 4472: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (0x7fae01f54400) [pid = 4472] [serial = 14] [outer = 0x7fae17c93180]
[task 2020-05-29T13:34:43.142Z] 13:34:43     INFO - GECKO(4130) | [Parent 4130, Main Thread] WARNING: NS_ENSURE_TRUE(GetWrapper()) failed: file /builds/worker/checkouts/gecko/dom/ipc/JSActor.cpp, line 90
[task 2020-05-29T13:34:43.283Z] 13:34:43     INFO - GECKO(4130) | [Parent 4130: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f019f540c00 == 15 [pid = 4130] [id = {a429abb6-5e10-4245-b20f-930d9838f700}] [url = about:blank]
[task 2020-05-29T13:34:43.283Z] 13:34:43     INFO - GECKO(4130) | [Parent 4130: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f01a13de000 == 14 [pid = 4130] [id = {1ecde347-e840-4fa4-bd81-84e918b45869}] [url = about:blank]
[task 2020-05-29T13:34:43.283Z] 13:34:43     INFO - GECKO(4130) | [Parent 4130: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f01a3e0bc00 == 13 [pid = 4130] [id = {5f6c0af3-799c-4473-9083-7883ce16726f}] [url = about:blank]
[task 2020-05-29T13:34:43.283Z] 13:34:43     INFO - GECKO(4130) | [Parent 4130: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f019f544400 == 12 [pid = 4130] [id = {e75269e8-5705-4e86-b0e8-a98f05f93b06}] [url = about:blank]
[task 2020-05-29T13:34:43.283Z] 13:34:43     INFO - GECKO(4130) | [Parent 4130: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f019d73d400 == 11 [pid = 4130] [id = {ac3f17dc-692a-49e5-a5b6-3ec451bd736b}] [url = about:blank]
[task 2020-05-29T13:34:43.283Z] 13:34:43     INFO - GECKO(4130) | [Parent 4130: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f019f83d000 == 10 [pid = 4130] [id = {1aa32321-134b-433b-a89f-c21435b8374f}] [url = about:blank]
[task 2020-05-29T13:34:43.483Z] 13:34:43     INFO - GECKO(4130) | [Child 4357: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 20 (0x7f1f03fd6800) [pid = 4357] [serial = 63] [outer = (nil)] [url = http://example.org/browser/remote/test/]
[task 2020-05-29T13:34:43.483Z] 13:34:43     INFO - GECKO(4130) | [Child 4357: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 19 (0x7f1f01985400) [pid = 4357] [serial = 55] [outer = (nil)] [url = about:blank]
[task 2020-05-29T13:34:43.484Z] 13:34:43     INFO - GECKO(4130) | [Child 4357: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 18 (0x7f1f016a1000) [pid = 4357] [serial = 60] [outer = (nil)] [url = http://example.org/browser/remote/test/browser/network/sjs-cookies.sjs?name=foo&value=bar&path=/browser/remote/test/browser/]
[task 2020-05-29T13:34:43.485Z] 13:34:43     INFO - GECKO(4130) | [Child 4357: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 17 (0x7f1f03fd3000) [pid = 4357] [serial = 62] [outer = (nil)] [url = http://example.org/browser/remote/test/browser/network/sjs-cookies.sjs]
[task 2020-05-29T13:34:43.485Z] 13:34:43     INFO - GECKO(4130) | [Child 4357: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 16 (0x7f1f01984c00) [pid = 4357] [serial = 59] [outer = (nil)] [url = about:blank]
[task 2020-05-29T13:34:43.486Z] 13:34:43     INFO - GECKO(4130) | [Child 4357: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 15 (0x7f1f0197e800) [pid = 4357] [serial = 56] [outer = (nil)] [url = http://example.org/browser/remote/test/browser/network/sjs-cookies.sjs?name=foo&value=bar]
[task 2020-05-29T13:34:43.488Z] 13:34:43     INFO - GECKO(4130) | [Child 4357: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 14 (0x7f1f016a2400) [pid = 4357] [serial = 66] [outer = (nil)] [url = about:blank]
[task 2020-05-29T13:34:43.489Z] 13:34:43     INFO - GECKO(4130) | [Child 4357: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 13 (0x7f1f03fca800) [pid = 4357] [serial = 61] [outer = (nil)] [url = http://example.org/browser/remote/test/browser/]
[task 2020-05-29T13:34:43.490Z] 13:34:43     INFO - GECKO(4130) | [Child 4357: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f1f0169f000 == 3 [pid = 4357] [id = {e935c4c4-beb3-453c-a157-461eaa4de3f7}] [url = http://example.org/foo/bar]
[task 2020-05-29T13:34:43.571Z] 13:34:43     INFO - GECKO(4130) | [Child 4357: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 12 (0x7f1f1f393520) [pid = 4357] [serial = 57] [outer = (nil)] [url = http://example.org/foo/bar]
[task 2020-05-29T13:34:44.339Z] 13:34:44     INFO - GECKO(4130) | 1590759284334	RemoteAgent	TRACE	(connection {3afed59f-2d1e-4485-aa34-bb43c348ab4f})-> {"id":1,"method":"Target.setDiscoverTargets","params":{"discover":true}}
[task 2020-05-29T13:34:44.339Z] 13:34:44     INFO - GECKO(4130) | 1590759284335	RemoteAgent	TRACE	<-(connection {3afed59f-2d1e-4485-aa34-bb43c348ab4f}) {"method":"Target.targetCreated","params":{"targetInfo":{"browserContextId":null,"targetId":"1841b8e8-367d-4c4f-aa87-a70e97967e27","type":"page","url":"about:blank"}}}
[task 2020-05-29T13:34:44.339Z] 13:34:44     INFO - GECKO(4130) | 1590759284335	RemoteAgent	TRACE	<-(connection {3afed59f-2d1e-4485-aa34-bb43c348ab4f}) {"method":"Target.targetCreated","params":{"targetInfo":{"targetId":"52d9c705-11c0-47d3-a265-4c4662b17cdb","type":"browser"}}}
[task 2020-05-29T13:34:44.339Z] 13:34:44     INFO - GECKO(4130) | 1590759284335	RemoteAgent	TRACE	<-(connection {3afed59f-2d1e-4485-aa34-bb43c348ab4f}) {"method":"Target.targetCreated","params":{"targetInfo":{"browserContextId":null,"targetId":"9f9c053b-d0dc-40e6-bc23-6df000c0d941","type":"page","url":"about:blank"}}}
[task 2020-05-29T13:34:44.342Z] 13:34:44     INFO - GECKO(4130) | 1590759284336	RemoteAgent	TRACE	<-(connection {3afed59f-2d1e-4485-aa34-bb43c348ab4f}) {"id":1}
[task 2020-05-29T13:34:44.363Z] 13:34:44     INFO - GECKO(4130) | [Parent 4130: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f01a2bf8c00 == 9 [pid = 4130] [id = {231bfd06-85a7-4cc6-ba9a-20b331fb6a97}] [url = about:blank]
[task 2020-05-29T13:34:44.364Z] 13:34:44     INFO - GECKO(4130) | [Parent 4130: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f01a2bf5800 == 8 [pid = 4130] [id = {1ef418b8-c783-40e7-8872-ac54a17e3615}] [url = about:blank]
[task 2020-05-29T13:34:44.379Z] 13:34:44     INFO - GECKO(4130) | 1590759284373	RemoteAgent	TRACE	(connection {3afed59f-2d1e-4485-aa34-bb43c348ab4f})-> {"id":2,"method":"Network.enable","params":{}}
[task 2020-05-29T13:34:44.380Z] 13:34:44     INFO - GECKO(4130) | 1590759284374	RemoteAgent	TRACE	<-(connection {3afed59f-2d1e-4485-aa34-bb43c348ab4f}) {"id":2}
[task 2020-05-29T13:34:44.381Z] 13:34:44     INFO - GECKO(4130) | 1590759284375	RemoteAgent	TRACE	(connection {3afed59f-2d1e-4485-aa34-bb43c348ab4f})-> {"id":3,"method":"Page.enable","params":{}}
[task 2020-05-29T13:34:44.401Z] 13:34:44     INFO - GECKO(4130) | 1590759284394	RemoteAgent	TRACE	<-(connection {3afed59f-2d1e-4485-aa34-bb43c348ab4f}) {"id":3}
[task 2020-05-29T13:34:44.402Z] 13:34:44     INFO - GECKO(4130) | 1590759284395	RemoteAgent	TRACE	(connection {3afed59f-2d1e-4485-aa34-bb43c348ab4f})-> {"id":4,"method":"Page.setLifecycleEventsEnabled","params":{"enabled":true}}
[task 2020-05-29T13:34:44.404Z] 13:34:44     INFO - GECKO(4130) | 1590759284396	RemoteAgent	TRACE	<-(connection {3afed59f-2d1e-4485-aa34-bb43c348ab4f}) {"id":4}
[task 2020-05-29T13:34:44.405Z] 13:34:44     INFO - GECKO(4130) | 1590759284398	RemoteAgent	TRACE	(connection {3afed59f-2d1e-4485-aa34-bb43c348ab4f})-> {"id":5,"method":"Page.navigate","params":{"url":"http://example.com/browser/remote/test/browser/network/doc_networkEvents.html"}}
[task 2020-05-29T13:34:44.410Z] 13:34:44     INFO - GECKO(4130) | 1590759284406	RemoteAgent	TRACE	<-(connection {3afed59f-2d1e-4485-aa34-bb43c348ab4f}) {"method":"Network.requestWillBeSent","params":{"requestId":"17738214932766","loaderId":"17738214932766","documentURL":"http: ... tion":"keep-alive"},"hasPostData":false,"isLinkPreload":false},"timestamp":1590759284.406,"type":"Document","frameId":"146"}}
[task 2020-05-29T13:34:44.466Z] 13:34:44     INFO - GECKO(4130) | 1590759284458	RemoteAgent	TRACE	<-(connection {3afed59f-2d1e-4485-aa34-bb43c348ab4f}) {"method":"Network.responseReceived","params":{"requestId":"17738214932766","loaderId":"17738214932766","timestamp":159075928 ... otePort":8888,"fromDiskCache":false,"protocol":"http/1.1","securityDetails":null,"securityState":"unknown"},"frameId":"146"}}
[task 2020-05-29T13:34:44.487Z] 13:34:44     INFO - GECKO(4130) | [Parent 4130: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 80 (0x7f01a13e8000) [pid = 4130] [serial = 68] [outer = (nil)] [url = about:blank]
[task 2020-05-29T13:34:44.487Z] 13:34:44     INFO - GECKO(4130) | [Parent 4130: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 79 (0x7f019d732000) [pid = 4130] [serial = 80] [outer = (nil)] [url = about:blank]
[task 2020-05-29T13:34:44.487Z] 13:34:44     INFO - GECKO(4130) | [Parent 4130: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 78 (0x7f01a13ea400) [pid = 4130] [serial = 71] [outer = (nil)] [url = about:blank]
[task 2020-05-29T13:34:44.488Z] 13:34:44     INFO - GECKO(4130) | [Parent 4130: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 77 (0x7f01a6e8ec00) [pid = 4130] [serial = 74] [outer = (nil)] [url = about:blank]
[task 2020-05-29T13:34:44.489Z] 13:34:44     INFO - GECKO(4130) | [Parent 4130: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f019d737c00 == 7 [pid = 4130] [id = {7cc4bce0-f539-4bd3-850b-a2f8404f604c}] [url = about:blank]
[task 2020-05-29T13:34:44.497Z] 13:34:44     INFO - GECKO(4130) | 1590759284490	RemoteAgent	TRACE	<-(connection {3afed59f-2d1e-4485-aa34-bb43c348ab4f}) {"id":5,"result":{"frameId":"146","loaderId":"17738214932766"}}
[task 2020-05-29T13:34:44.532Z] 13:34:44     INFO - GECKO(4130) | [Child 4472: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 4 (0x7fae01f59000) [pid = 4472] [serial = 15] [outer = 0x7fae17c93180]
[task 2020-05-29T13:34:49.142Z] 13:34:49     INFO - GECKO(4130) | 1590759289132	RemoteAgent	TRACE	<-(connection {3afed59f-2d1e-4485-aa34-bb43c348ab4f}) {"method":"Page.frameStartedLoading","params":{"frameId":"146"}}
[task 2020-05-29T13:34:49.143Z] 13:34:49     INFO - GECKO(4130) | 1590759289133	RemoteAgent	TRACE	<-(connection {3afed59f-2d1e-4485-aa34-bb43c348ab4f}) {"method":"Page.lifecycleEvent","params":{"frameId":"146","loaderId":"17738214932766","name":"init","timestamp":1590759284.489}}
[task 2020-05-29T13:34:49.144Z] 13:34:49     INFO - GECKO(4130) | 1590759289135	RemoteAgent	TRACE	<-(connection {3afed59f-2d1e-4485-aa34-bb43c348ab4f}) {"method":"Page.frameNavigated","params":{"frame":{"id":"146","parentId":null,"url":"http://example.com/browser/remote/test/browser/network/doc_networkEvents.html"}}}
[task 2020-05-29T13:34:49.320Z] 13:34:49     INFO - TEST-INFO | started process screentopng
[task 2020-05-29T13:34:50.022Z] 13:34:50     INFO - TEST-INFO | screentopng: exit 0
[task 2020-05-29T13:34:50.024Z] 13:34:50     INFO - Buffered messages logged at 13:34:42
[task 2020-05-29T13:34:50.024Z] 13:34:50     INFO - Entering test bound documentNavigationWithScriptResource
[task 2020-05-29T13:34:50.025Z] 13:34:50     INFO - CDP server started
[task 2020-05-29T13:34:50.026Z] 13:34:50     INFO - Buffered messages logged at 13:34:44
[task 2020-05-29T13:34:50.026Z] 13:34:50     INFO - CDP client instantiated
[task 2020-05-29T13:34:50.027Z] 13:34:50     INFO - Received Network.requestWillBeSent for http://example.com/browser/remote/test/browser/network/doc_networkEvents.html
[task 2020-05-29T13:34:50.027Z] 13:34:50     INFO - Received Network.responseReceived for http://example.com/browser/remote/test/browser/network/doc_networkEvents.html
[task 2020-05-29T13:34:50.027Z] 13:34:50     INFO - Recorded Page.navigate
[task 2020-05-29T13:34:50.027Z] 13:34:50     INFO - TEST-PASS | remote/test/browser/network/browser_navigationEvents.js | Page.navigate returned a frameId - 
[task 2020-05-29T13:34:50.027Z] 13:34:50     INFO - Wait for events
[task 2020-05-29T13:34:50.027Z] 13:34:50     INFO - Buffered messages finished
[task 2020-05-29T13:34:50.028Z] 13:34:50     INFO - TEST-UNEXPECTED-FAIL | remote/test/browser/network/browser_navigationEvents.js | Expected number of events - Got 3, expected 8
[task 2020-05-29T13:34:50.028Z] 13:34:50     INFO - Stack trace:
[task 2020-05-29T13:34:50.028Z] 13:34:50     INFO - chrome://mochikit/content/browser-test.js:test_is:1327
[task 2020-05-29T13:34:50.028Z] 13:34:50     INFO - chrome://mochitests/content/browser/remote/test/browser/network/browser_navigationEvents.js:documentNavigationWithScriptResource:27
[task 2020-05-29T13:34:50.028Z] 13:34:50     INFO - chrome://mochitests/content/browser/remote/test/browser/head.js:fn:72
[task 2020-05-29T13:34:50.028Z] 13:34:50     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1064
[task 2020-05-29T13:34:50.028Z] 13:34:50     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1104
[task 2020-05-29T13:34:50.028Z] 13:34:50     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:927
[task 2020-05-29T13:34:50.028Z] 13:34:50     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:918
[task 2020-05-29T13:34:50.028Z] 13:34:50     INFO - Received events: Network.requestWillBeSent(Document),Network.responseReceived(Document),Page.navigate(undefined)
[task 2020-05-29T13:34:50.028Z] 13:34:50     INFO - TEST-PASS | remote/test/browser/network/browser_navigationEvents.js | Expected number of Network events for document - 
[task 2020-05-29T13:34:50.031Z] 13:34:50     INFO - GECKO(4130) | 1590759289427	RemoteAgent	TRACE	<-(connection {3afed59f-2d1e-4485-aa34-bb43c348ab4f}) {"method":"Network.requestWillBeSent","params":{"requestId":"19207093747719","documentURL":"http://example.com/browser/remote ... ection":"keep-alive"},"hasPostData":false,"isLinkPreload":false},"timestamp":1590759289.426,"type":"Script","frameId":"146"}}
[task 2020-05-29T13:34:50.031Z] 13:34:50     INFO - CDP client closed
[task 2020-05-29T13:34:50.032Z] 13:34:50     INFO - GECKO(4130) | 1590759289477	RemoteAgent	TRACE	<-(connection {3afed59f-2d1e-4485-aa34-bb43c348ab4f}) {"method":"Target.targetDestroyed","params":{"targetId":"1841b8e8-367d-4c4f-aa87-a70e97967e27"}}
[task 2020-05-29T13:34:50.032Z] 13:34:50     INFO - GECKO(4130) | 1590759289480	RemoteAgent	TRACE	<-(connection {3afed59f-2d1e-4485-aa34-bb43c348ab4f}) {"method":"Target.targetDestroyed","params":{"targetId":"52d9c705-11c0-47d3-a265-4c4662b17cdb"}}
[task 2020-05-29T13:34:50.034Z] 13:34:50     INFO - GECKO(4130) | 1590759289480	RemoteAgent	TRACE	<-(connection {3afed59f-2d1e-4485-aa34-bb43c348ab4f}) {"method":"Target.targetDestroyed","params":{"targetId":"9f9c053b-d0dc-40e6-bc23-6df000c0d941"}}
[task 2020-05-29T13:34:50.034Z] 13:34:50     INFO - GECKO(4130) | [Child 4357: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 11 (0x7f1f09591800) [pid = 4357] [serial = 64] [outer = (nil)] [url = http://example.org/foo/bar]
[task 2020-05-29T13:34:50.035Z] 13:34:50     INFO - GECKO(4130) | [Child 4357: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f1f01699800 == 2 [pid = 4357] [id = {0376eaf4-11a8-4138-9fb9-a4bd50d13373}] [url = http://example.org/browser/remote/test/browser/network/sjs-cookies.sjs?name=foo&value=bar&httpOnly]
[task 2020-05-29T13:34:50.035Z] 13:34:50     INFO - GECKO(4130) | [Child 4357: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f1f0169ec00 == 1 [pid = 4357] [id = {cebe5623-4243-4ed8-aaab-5128515c1840}] [url = http://example.org/browser/remote/test/browser/network/sjs-cookies.sjs?name=foo&value=bar&sameSite=Strict]
[task 2020-05-29T13:34:50.035Z] 13:34:50     INFO - GECKO(4130) | [Child 4357: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 10 (0x7f1f016a0800) [pid = 4357] [serial = 70] [outer = (nil)] [url = about:blank]
[task 2020-05-29T13:34:50.039Z] 13:34:50     INFO - GECKO(4130) | [Child 4357: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 9 (0x7f1f03fd4000) [pid = 4357] [serial = 72] [outer = (nil)] [url = http://example.org/browser/remote/test/browser/network/sjs-cookies.sjs?name=foo&value=bar&sameSite=Lax]
[task 2020-05-29T13:34:50.039Z] 13:34:50     INFO - CDP server stopped
[task 2020-05-29T13:34:50.040Z] 13:34:50     INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-05-29T13:34:50.040Z] 13:34:50     INFO - TEST-UNEXPECTED-FAIL | remote/test/browser/network/browser_navigationEvents.js | Uncaught exception - at chrome://mochitests/content/browser/remote/test/browser/network/browser_navigationEvents.js:41 - TypeError: can't access property "length", resourceEvents is undefined
[task 2020-05-29T13:34:50.040Z] 13:34:50     INFO - Stack trace:
[task 2020-05-29T13:34:50.041Z] 13:34:50     INFO - documentNavigationWithScriptResource@chrome://mochitests/content/browser/remote/test/browser/network/browser_navigationEvents.js:41:1
[task 2020-05-29T13:34:50.041Z] 13:34:50     INFO - async*fn@chrome://mochitests/content/browser/remote/test/browser/head.js:72:13
[task 2020-05-29T13:34:50.041Z] 13:34:50     INFO - Async*Tester_execTest/<@chrome://mochikit/content/browser-test.js:1064:34
[task 2020-05-29T13:34:50.041Z] 13:34:50     INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:1104:11
[task 2020-05-29T13:34:50.042Z] 13:34:50     INFO - nextTest/<@chrome://mochikit/content/browser-test.js:927:14
[task 2020-05-29T13:34:50.042Z] 13:34:50     INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:918:23
[task 2020-05-29T13:34:50.042Z] 13:34:50     INFO - Leaving test bound documentNavigationWithScriptResource
[task 2020-05-29T13:34:50.044Z] 13:34:50     INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "http://example.com/browser/remote/test/browser/network/doc_networkEvents.html" line: 0}]
[task 2020-05-29T13:34:50.045Z] 13:34:50     INFO - GECKO(4130) | [Child 4357: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 8 (0x7f1f1f393180) [pid = 4357] [serial = 65] [outer = (nil)] [url = http://example.org/browser/remote/test/browser/network/sjs-cookies.sjs?name=foo&value=bar&httpOnly]
[task 2020-05-29T13:34:50.045Z] 13:34:50     INFO - GECKO(4130) | [Child 4357: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 7 (0x7f1f1f393350) [pid = 4357] [serial = 69] [outer = (nil)] [url = http://example.org/browser/remote/test/browser/network/sjs-cookies.sjs?name=foo&value=bar&sameSite=Strict]
[task 2020-05-29T13:34:50.048Z] 13:34:50     INFO - GECKO(4130) | MEMORY STAT | vsize 3413MB | residentFast 518MB | heapAllocated 200MB
[task 2020-05-29T13:34:50.048Z] 13:34:50     INFO - TEST-OK | remote/test/browser/network/browser_navigationEvents.js | took 7171ms

Looks like the increase of the timeout on bug 1638518 was not enough. Lets see how often it still fails.

OS: Unspecified → Linux
Hardware: Unspecified → x86_64
Summary: Intermittent remote/test/browser/network/browser_navigationEvents.js | Expected number of events - Got X, expected Y → Intermittent remote/cdp/test/browser/network/browser_navigationEvents.js | Expected number of events - Got X, expected Y
Status: NEW → RESOLVED
Closed: 4 years ago
Component: Agent → CDP
Resolution: --- → WORKSFORME
Summary: Intermittent remote/cdp/test/browser/network/browser_navigationEvents.js | Expected number of events - Got X, expected Y → Intermittent remote/cdp/test/browser/network/browser_navigationEvents.js | Received expected number of events - Got X, expected Y
Status: RESOLVED → REOPENED
Resolution: WORKSFORME → ---
Status: REOPENED → RESOLVED
Closed: 4 years ago3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

Since the reopening of the bug the failure only happens for tsan builds.

Blocks: tsan

The problem here seems to be related to our events timeout setting when waiting for the event. Given that the TSAN builds are kinda slow we don't wait long enough and as such this particular tests and maybe others fail. I filed bug 1809105 to get this fixed.

Depends on: 1809105

There are no more failures on mozilla-central since the patch from bug 1809105 has been landed. Beta has a very low failure rate so not sure if it is worth uplifting at this time.

Assignee: nobody → hskupin
Status: REOPENED → RESOLVED
Closed: 3 years ago2 years ago
Resolution: --- → FIXED
Target Milestone: --- → 111 Branch
You need to log in before you can comment on or make changes to this bug.